
from IPython.display import display, HTML
display(HTML("<style>.container {width:100% !important; }</style>"))

import glob
import pandas as pd
import numpy as np
import hvplot.pandas
import plotly.express as px
import plotly.graph_objects as go
pd.options.mode.chained_assignment = None

import datetime as dt
%autosave 30

Autosaving every 30 seconds


CPU_FREQ=2.60

rdtsc_df_dict = []
ttt_df_dict = []
for filename in glob.glob("exchange*.log") + glob.glob("*_1.log"):
    print('processing {}'.format(filename))
    for line in open(filename):
        tokens = line.strip().split(' ')
        if len(tokens) != 4:
            continue

        try:
            time = tokens[0]
            tag = tokens[2]
            latency = float(tokens[3])
            latency_rdtsc = latency / CPU_FREQ
            time_datetime = pd.to_datetime(time, format='%H:%M:%S.%f')
        except:
            continue

        if ' RDTSC ' in line:
            if tokens[1] != 'RDTSC':
                continue

            rdtsc_df_dict.append({'timestamp':time, 'tag':tag, 'latency':latency_rdtsc})
        elif ' TTT ' in line:
            if tokens[1] != 'TTT':
                continue

            ttt_df_dict.append({'timestamp':time, 'tag':tag, 'latency':latency})
        
rdtsc_df = pd.DataFrame.from_dict(rdtsc_df_dict)
rdtsc_df = rdtsc_df.drop_duplicates().sort_values(by='timestamp')
rdtsc_df['timestamp'] = pd.to_datetime(rdtsc_df['timestamp'], format='%H:%M:%S.%f')

ttt_df = pd.DataFrame.from_dict(ttt_df_dict)
ttt_df = ttt_df.drop_duplicates().sort_values(by='timestamp')
ttt_df['timestamp'] = pd.to_datetime(ttt_df['timestamp'], format='%H:%M:%S.%f')

processing exchange_snapshot_synthesizer.log
processing exchange_order_server.log
processing exchange_main.log
processing exchange_matching_engine.log
processing exchange_market_data_publisher.log
processing trading_main_1.log
processing trading_order_gateway_1.log
processing trading_engine_1.log
processing trading_market_data_consumer_1.log


for tag in rdtsc_df['tag'].unique():
    print(tag)
    
    fig = go.Figure()

    t_df = rdtsc_df[rdtsc_df['tag'] == tag].copy()
    t_df = t_df[t_df['latency'] > 0]

    q_hi = t_df['latency'].quantile(0.99)
    q_lo = t_df['latency'].quantile(0.01)
    t_df = t_df[(t_df['latency'] < q_hi) & (t_df['latency'] > q_lo)]

    mean = t_df['latency'].astype(float).mean()
    print('{} has {} observations mean {}'.format(tag, len(t_df), mean))

    rolling_window = max(1, int(len(t_df) / 100))

    use_micros = False
    if mean >= 1000:
        use_micros = True
        t_df['latency'] = t_df['latency'].astype(float) / 1000

    fig.add_trace(go.Scatter(x=t_df['timestamp'], y=t_df['latency'], name=tag))
    fig.add_trace(go.Scatter(x=t_df['timestamp'], y=t_df['latency'].rolling(rolling_window).mean(), name=tag + ' mean'))
#     fig.add_trace(go.Scatter(x=t_df['timestamp'], y=t_df['latency'].rolling(rolling_window).std(), name=tag + ' std'))

    fig.update_layout(title='performance ' + tag + ' ' + ('microseconds' if use_micros else 'nanoseconds'), height=700, hovermode='x')
    fig.show()

Exchange_FIFOSequencer_addClientRequest
Exchange_FIFOSequencer_addClientRequest has 10487 observations mean 82.03394679126538

Exchange_FIFOSequencer_sequenceAndPublish
Exchange_FIFOSequencer_sequenceAndPublish has 10374 observations mean 53909.935971585764

Exchange_MEOrderBook_checkForMatch
Exchange_MEOrderBook_checkForMatch has 5703 observations mean 163383.84224227464

Exchange_MEOrderBook_addOrder
Exchange_MEOrderBook_addOrder has 3636 observations mean 497.1089320470508

Exchange_MEOrderBook_add
Exchange_MEOrderBook_add has 5708 observations mean 337468.20750902913

Exchange_MatchingEngine_processClientRequest
Exchange_MatchingEngine_processClientRequest has 11326 observations mean 254875.95264130185

Exchange_MEOrderBook_removeOrder
Exchange_MEOrderBook_removeOrder has 2969 observations mean 1281.9594787159622

Exchange_MEOrderBook_cancel
Exchange_MEOrderBook_cancel has 5616 observations mean 56774.474989042305

Exchange_McastSocket_send
Exchange_McastSocket_send has 12158 observations mean 433.9329279866374

Exchange_TCPSocket_send
Exchange_TCPSocket_send has 18355 observations mean 185.35437839197033


HOPS = [
    ['T1_OrderServer_TCP_read', 'T2_OrderServer_LFQueue_write'],
    ['T2_OrderServer_LFQueue_write', 'T3_MatchingEngine_LFQueue_read'],
    ['T3_MatchingEngine_LFQueue_read', 'T4_MatchingEngine_LFQueue_write'], ['T3_MatchingEngine_LFQueue_read', 'T4t_MatchingEngine_LFQueue_write'],
    ['T4_MatchingEngine_LFQueue_write', 'T5_MarketDataPublisher_LFQueue_read'], ['T4t_MatchingEngine_LFQueue_write', 'T5t_OrderServer_LFQueue_read'],
    ['T5_MarketDataPublisher_LFQueue_read', 'T6_MarketDataPublisher_UDP_write'], ['T5t_OrderServer_LFQueue_read', 'T6t_OrderServer_TCP_write'],
    ['T7_MarketDataConsumer_UDP_read', 'T8_MarketDataConsumer_LFQueue_write'], ['T7t_OrderGateway_TCP_read', 'T8t_OrderGateway_LFQueue_write'],
    ['T8_MarketDataConsumer_LFQueue_write', 'T9_TradeEngine_LFQueue_read'], ['T8t_OrderGateway_LFQueue_write', 'T9t_TradeEngine_LFQueue_read'],
    ['T9_TradeEngine_LFQueue_read', 'T10_TradeEngine_LFQueue_write'], ['T9t_TradeEngine_LFQueue_read', 'T10_TradeEngine_LFQueue_write'],
    ['T10_TradeEngine_LFQueue_write', 'T11_OrderGateway_LFQueue_read'],
    ['T11_OrderGateway_LFQueue_read', 'T12_OrderGateway_TCP_write'],
    # exchange <-> client
    ['T12_OrderGateway_TCP_write', 'T1_OrderServer_TCP_read'],
    ['T6_MarketDataPublisher_UDP_write', 'T7_MarketDataConsumer_UDP_read'], ['T6t_OrderServer_TCP_write', 'T7t_OrderGateway_TCP_read'],
]


for tags in HOPS:
    tag_p, tag_n = tags
    print('{} => {}. {} => {}.'.format(tag_p, len(ttt_df[ttt_df['tag'] == tag_p]), tag_n, len(ttt_df[ttt_df['tag'] == tag_n])))

    fig = go.Figure()

    t_df = ttt_df[(ttt_df['tag'] == tag_n) | (ttt_df['tag'] == tag_p)]
    t_df['latency_diff'] = t_df['latency'].diff()
    t_df = t_df[t_df['latency_diff'] > 0]
    t_df = t_df[t_df.tag == tag_n]

    q_hi = t_df['latency_diff'].quantile(0.99)
    q_lo = t_df['latency_diff'].quantile(0.01)
    t_df = t_df[(t_df['latency_diff'] < q_hi) & (t_df['latency_diff'] > q_lo)]

    mean = t_df['latency_diff'].astype(float).mean()
    print('{} has {} observations mean {}'.format(tag_n, len(t_df), mean))

    rolling_window = max(1, int(len(t_df) / 100))

    unit = 'nanoseconds'
    if mean >= 1000000:
        unit = 'milliseconds'
        t_df['latency_diff'] = t_df['latency_diff'].astype(float) / 1000000
    elif mean >= 1000:
        unit = 'microseconds'
        t_df['latency_diff'] = t_df['latency_diff'].astype(float) / 1000

    tag_name = tag_p + ' -> ' + tag_n
    fig.add_trace(go.Scatter(x=t_df['timestamp'], y=t_df['latency_diff'], name=tag_name))
    fig.add_trace(go.Scatter(x=t_df['timestamp'], y=t_df['latency_diff'].rolling(rolling_window).mean(), name=tag_name + ' mean'))

    fig.update_layout(title='performance ' + tag_name + ' ' + unit, height=700, hovermode='x')
    fig.show()

T1_OrderServer_TCP_read => 10870. T2_OrderServer_LFQueue_write => 11558.
T2_OrderServer_LFQueue_write has 11306 observations mean 131404.89509994694

T2_OrderServer_LFQueue_write => 11558. T3_MatchingEngine_LFQueue_read => 11558.
T3_MatchingEngine_LFQueue_read has 10784 observations mean 3189226.278931751

T3_MatchingEngine_LFQueue_read => 11558. T4_MatchingEngine_LFQueue_write => 12447.
T4_MatchingEngine_LFQueue_write has 12175 observations mean 344765.1561396304

T3_MatchingEngine_LFQueue_read => 11558. T4t_MatchingEngine_LFQueue_write => 18802.
T4t_MatchingEngine_LFQueue_write has 18406 observations mean 259917.150494404

T4_MatchingEngine_LFQueue_write => 12447. T5_MarketDataPublisher_LFQueue_read => 12447.
T5_MarketDataPublisher_LFQueue_read has 12066 observations mean 1910351.753356539

T4t_MatchingEngine_LFQueue_write => 18802. T5t_OrderServer_LFQueue_read => 18802.
T5t_OrderServer_LFQueue_read has 18290 observations mean 1908845.1604155276

T5_MarketDataPublisher_LFQueue_read => 12447. T6_MarketDataPublisher_UDP_write => 12447.
T6_MarketDataPublisher_UDP_write has 12188 observations mean 317922.17394158186

T5t_OrderServer_LFQueue_read => 18802. T6t_OrderServer_TCP_write => 18802.
T6t_OrderServer_TCP_write has 18342 observations mean 273255.22625667864

T7_MarketDataConsumer_UDP_read => 6521. T8_MarketDataConsumer_LFQueue_write => 12447.
T8_MarketDataConsumer_LFQueue_write has 12186 observations mean 79705.87099950764

T7t_OrderGateway_TCP_read => 2127. T8t_OrderGateway_LFQueue_write => 2411.
T8t_OrderGateway_LFQueue_write has 2359 observations mean 65511.90843577787


import session_info
session_info.show()

-----
hvplot              0.8.3
numpy               1.24.3
pandas              2.0.1
plotly              5.14.1
session_info        1.0.0
-----

PIL                 9.0.1
apport_python_hook  NA
arrow               1.2.3
asttokens           NA
attr                23.1.0
backcall            0.2.0
bleach              6.0.0
bokeh               3.1.1
bs4                 4.12.2
cffi                1.15.1
chardet             4.0.0
colorama            0.4.4
colorcet            3.0.1
comm                0.1.3
cython_runtime      NA
dateutil            2.8.2
debugpy             1.6.7
decorator           5.1.1
defusedxml          0.7.1
executing           1.2.0
fastjsonschema      NA
fqdn                NA
google              NA
holoviews           1.16.0
idna                3.3
ipykernel           6.23.1
ipython_genutils    0.2.0
isoduration         NA
jedi                0.18.2
jinja2              3.1.2
jsonpointer         2.3
jsonschema          4.17.3
jupyterlab_pygments 0.2.2
markupsafe          2.0.1
mistune             2.0.5
nbclient            0.8.0
nbconvert           7.4.0
nbformat            5.8.0
netifaces           0.11.0
packaging           23.1
pandocfilters       NA
panel               1.0.2
param               1.13.0
parso               0.8.3
pexpect             4.8.0
pickleshare         0.7.5
pkg_resources       NA
platformdirs        3.5.1
prompt_toolkit      3.0.38
psutil              5.9.5
ptyprocess          0.7.0
pure_eval           0.2.2
pydev_ipython       NA
pydevconsole        NA
pydevd              2.9.5
pydevd_file_utils   NA
pydevd_plugins      NA
pydevd_tracing      NA
pygments            2.15.1
pyparsing           2.4.7
pyrsistent          NA
pytz                2022.1
pyviz_comms         2.2.1
rfc3339_validator   0.1.4
rfc3986_validator   0.1.1
sitecustomize       NA
six                 1.16.0
soupsieve           2.4.1
stack_data          0.6.2
tenacity            NA
tinycss2            1.2.1
tornado             6.3.2
tqdm                4.65.0
traitlets           5.9.0
tzdata              2023.3
uri_template        NA
wcwidth             0.2.6
webcolors           1.13
webencodings        0.5.1
xyzservices         2023.5.0
yaml                5.4.1
zmq                 25.0.2
zoneinfo            NA

-----
IPython             8.13.2
jupyter_client      8.2.0
jupyter_core        5.3.0
notebook            6.5.4
-----
Python 3.10.6 (main, May 29 2023, 11:10:38) [GCC 11.3.0]
Linux-5.19.0-43-generic-x86_64-with-glibc2.35
-----
Session information updated at 2023-06-07 15:37